【Python】 loggingモジュールでLEVEL毎にファイルの出力先を変更しrotateさせる方法

はじめに

データアナリティクス事業本部ビッグデータチームのyosh-kです。
今回はpythonのloggingモジュールを使用して、LEVEL毎にファイルの出力先を変更し、rotateさせる実装を行ったので、その備忘ログという意味でもブログに残したいと思います。

前提条件

前提条件として、以下の条件でLEVEL毎にlogファイルの出力先を分けることにします。ERRORとCRITICALレベルについても、WARNINGと分ける事も考えましたが、分割しすぎても全てのログファイルを見ながらデバッグするのは効率的ではないと考え、今回はWARNING以上は全て、同一のファイルとしてあります。こちらの設定については、アプリケーションの性質やログ出力の頻度に応じて、ファイルの分割方法を適切に選択する必要があると考えています。

レベル	ログファイル名
DEBUG	./log/debug.log
INFO	./log/info.log
WARNING以上	./log/error.log

Logging HOWTO

実装

実装したソースコードはgithub上に残してあるので、全体感を確認したい場合はそちらをご参照ください。

14_python_loggger_implement

以下は実装したフォルダ構成になります。actions.pyとmain.pyはloggingのテスト用に実装したファイルで、今回の実装の中心はmy_logger.pyになります。

.
├── lib
│   ├── actions.py
│   └── my_logger.py
└── main.py

my_logger.py

import os
import logging, logging.handlers


class DebugFilter(logging.Filter):
    def filter(self, record):
        return record.levelno == logging.DEBUG


class InfoFilter(logging.Filter):
    def filter(self, record):
        return record.levelno == logging.INFO


class MyLogger:
    def __init__(self, name):
        self._make_log_dir()
        self.logger = logging.getLogger(name)
        self.logger.setLevel(logging.DEBUG)

        formatter = logging.Formatter(
            "%(asctime)s - %(levelname)s - %(name)s - %(funcName)s  - line:%(lineno)d - %(message)s"
        )

        debug_file_path = "log/debug.log"
        debug_handler = logging.handlers.RotatingFileHandler(
            filename=debug_file_path, encoding="utf-8", maxBytes=100, backupCount=5
        )
        debug_handler.setLevel(logging.DEBUG)
        debug_handler.setFormatter(formatter)
        debug_filter = DebugFilter()
        debug_handler.addFilter(debug_filter)
        self.logger.addHandler(debug_handler)

        info_file_path = "log/info.log"
        info_handler = logging.handlers.RotatingFileHandler(
            filename=info_file_path, encoding="utf-8", maxBytes=100, backupCount=5
        )
        info_handler.setLevel(logging.INFO)
        info_handler.setFormatter(formatter)
        info_filter = InfoFilter()
        info_handler.addFilter(info_filter)
        self.logger.addHandler(info_handler)

        error_file_path = "log/error.log"
        error_handler = logging.handlers.RotatingFileHandler(
            filename=error_file_path, encoding="utf-8", maxBytes=100, backupCount=5
        )
        error_handler.setLevel(logging.WARNING)
        error_handler.setFormatter(formatter)
        self.logger.addHandler(error_handler)

        # /**コンソール出力設定例
        # import sys
        # console_handler = logging.StreamHandler(sys.stdout)
        # console_handler.setLevel(logging.INFO)
        # console_handler.setFormatter(formatter)
        # info_filter = InfoFilter()
        # console_handler.addFilter(info_filter)
        # self.logger.addHandler(console_handler)

        # error_handler = logging.StreamHandler(sys.stderr)
        # error_handler.setLevel(logging.WARNING)
        # error_handler.setFormatter(formatter)
        # self.logger.addHandler(error_handler)
        # **/

    def _make_log_dir(self):
        LOG_DIR = "log"

        if not os.path.exists(LOG_DIR):
            # ディレクトリが存在しない場合、ディレクトリを作成する
            os.makedirs(LOG_DIR)

ClassであるMyLoggerを呼び出す事で、log出力の設定がどのファイルでもできるように実装しました。 このClassの__init__メソッドでは以下の処理が行われています。

1. _make_log_dir()を呼び出す事でlogディレクトリが存在しない場合に作成する
2. ロガーを初期化する
   1. ロガー名を引数nameで指定して、logging.getLoggerメソッドを呼び出す
   2. self.logger.setLevelログレベルをlogging.DEBUGに設定する
   3. logging.Formatterでログ出力のフォーマットを指定する
3. レベル毎のファイルハンドラを作成する
   1. ログ出力先のファイルパスを_file_pathで指定する
   2. logging.handlers.RotatingFileHandlerで指定されたファイルサイズを超えた場合に自動的にログファイルをバックアップし、新しいファイルにログを書き込むログハンドラを設定する
   3. filenameに出力先パスを指定する
   4. encodingで文字コードを指定する
   5. maxBytesで最大ファイルサイズを指定する
   6. backupCountでバックアップファイル数を指定する
   7. レベル毎のログレベルをsetLevelで設定する
   8. ログ出力のフォーマットをsetFormatterで指定する
   9. DEBUGとINFOレベルに関しては同レベル以外出力しないようにフィルターをaddFilterで追加する
   10. ロガーにレベル毎のファイルハンドラをaddHandlerで追加する

※ コメントアウトしているコンソール出力設定例はコンソールでの標準出力と標準エラー出力になります。今回は使用しませんが、参考として残しておきます。

• ログ出力フォーマットの参考：
  • LogRecord 属性
  • 【Python】logging フォーマットの出力例（１０種類以上）
• ログフィルターの参考：
  • Python】ロギングのフィルタで出力するログ記録をフィルタリング

main.py

from lib.my_logger import MyLogger
from lib.actions import test

my_logger = MyLogger(__name__)
logger = my_logger.logger


def main():

    logger.debug("debug")
    logger.info("info")
    logger.error("error")
    logger.critical("critical")
    test()


if __name__ == "__main__":
    main()

main.pyはレベル毎の出力先をtestするために全てを呼び出すように生成しています。

actions.py

from lib.my_logger import MyLogger

my_logger = MyLogger(__name__)
logger = my_logger.logger


def test():
    logger.debug("debug")
    logger.info("info")
    logger.error("error")
    logger.critical("critical")

actions.pyはmain.pyと同様にloggerを呼び出し、かつlogとして見分ける事ができるかを確認するために作成しました。

実行結果

それではmain.pyを実行してみます。

実際にlog rotateされたファイルが分割して生成されている事を確認できました。maxBytes=100に対して70前後のByteでrotateされているのは、次の一行で上限を越える為のようですね。

次にエラーレベル毎の出力を確認したいため、logディレクトリを削除して、maxBytes=10000して実行してみます。

debug.log, info.log, error.log想定通り、ログレベル毎に分類され、ファイル名も識別できているので問題なさそうです！

最後に

レベル毎にファイルを分割し過ぎても、いざエラー解析する時に苦労するため、アプリケーションの性質やログ出力の頻度に応じて、ファイルの分割方法を適切に選択することが重要であると感じました。このブログが少しでもお役に立つと幸いです。